Skip to content

SciMLLogging Integration #756

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom
Open
wants to merge 58 commits into
base: main
Choose a base branch
from
Open

SciMLLogging Integration #756

wants to merge 58 commits into from
+1,526 −359

Conversation

jClugstor
Copy link
Member

@jClugstor jClugstor commented Aug 22, 2025 •
edited
Loading

Checklist

  • Appropriate tests were added
  • Any code changes were done in a way that does not break public API
  • All documentation related to code changes were updated
  • The new code follows the
    contributor guidelines, in particular the SciML Style Guide and
    COLPRAC.
  • Any new documentation only uses public API

Additional context

using LinearSolve, BenchmarkTools
using SciMLLogging: Verbosity
n = 4
A = rand(n, n)
b1 = rand(n);
b2 = rand(n);
prob = LinearProblem(A, b1)

With this PR:

@btime solve(prob, verbose=false)
365.015 ns (11 allocations: 928 bytes)

using SciMLLogging: Verbosity
@btime solve(prob, verbose = LinearVerbosity(Verbosity.None()))
363.893 ns (12 allocations: 960 bytes)

@btime solve(prob, verbose=true)
 432.445 ns (15 allocations: 1.03 KiB)

@report_opt solve(prob, verbose = LinearVerbosity(Verbosity.None()))
No errors detected

@report_opt solve(prob, verbose = false)
No errors detected

@profview for i in 1:10000000 init(prob, verbose = false) end
NewPRProfile

From the profile we can see that the constructor for LinearVerbosity doesn't even get called from __init, which should indicate that it got compiled out.

With current main (Bool verbosity system)

`@btime solve(prob, verbose=false)`
 `359.857 ns (11 allocations: 928 bytes)`

`@btime solve(prob, verbose=true)`
` 329.573 ns (11 allocations: 928 bytes)`

@profview for i in 1:10000000 init(prob, verbose = false) end
OldVerbosityProfile

@jClugstor
Copy link
Member Author

@ChrisRackauckas

@jClugstor
Copy link
Member Author

I rewrote SciMLLogging to get rid of the Moshi.jl dependency, and to make it easier to implement Verbosity "presets". I also rewrote the stuff in LinearVerbosity. This way has fewer dependencies, and is still able to compile out the logging code. Better yet, even if logging is enabled, if the code goes through an @SciMLMessage where the verbosity toggle is set to Verbosity.Silent() the it doesn't go through any of the SciMLLogging code because it gets compiled away, at least in the testing I've done so far. Which means that no time is wasted getting the verbosity type, checking if it's None, etc. anymore.

With this PR:

n = 4
A = rand(n, n)
b1 = rand(n);
b2 = rand(n);
prob = LinearProblem(A, b1)

@b solve(prob, verbose = false)
373.308 ns (12 allocs: 1008 bytes)

@b solve(prob, verbose = true )
364.000 ns (12 allocs: 1008 bytes)

@b solve(prob, verbose = LinearVerbosity()) 
378.214 ns (13 allocs: 1.000 KiB)

@b solve(prob)
378.121 ns (12 allocs: 1008 bytes)

verb = LinearVerbosity()

@b solve(prob, verbose = verb)
527.854 ns (13 allocs: 960 bytes)

opt = @report_opt solve(prob, LUFactorization(), verbose = LinearVerbosity())
No errors detected

opt = @report_opt solve(prob, LUFactorization(), verbose = LinearVerbosity(Verbosity.None()))
No errors detected

opt = @report_opt solve(prob, LUFactorization(), verbose = false)
No errors detected

cache = init(prob, LUFactorization())

@b solve!(cache) 
101.288 ns (1 allocs: 48 bytes)

A = [1.0 0 0 0
    0 1 0 0
    0 0 1 0
    0 0 0 0]
b = rand(4)
prob = LinearProblem(A, b)

verb = LinearVerbosity(default_lu_fallback = Verbosity.Silent())

cache = init(prob, verbose = verb)

@b solve!(cache)
104.880 ns (1 allocs: 48 bytes)

cache = init(prob, verbose=false)

@b solve!(cache)
104.812 ns (1 allocs: 48 bytes)

LinearSolve v3.40.1:

n = 4
A = rand(n, n)
b1 = rand(n);
b2 = rand(n);
prob = LinearProblem(A, b1)

@b solve(prob, verbose = false)
252.902 ns (11 allocs: 928 bytes)

@b solve(prob, verbose = true )
250.919 ns (11 allocs: 928 bytes)

A = [1.0 0 0 0
    0 1 0 0
    0 0 1 0
    0 0 0 0]
b = rand(4)
prob = LinearProblem(A, b)

cache = init(prob, verbose = false)

104.171 ns (1 allocs: 48 bytes)

So the creation of the LinearVerbosity adds a little bit of overhead to init, but once the cache is created, if there's no printing, there's no overhead.

@jClugstor
Copy link
Member Author

Got rid of the Verbosity submodule in SciMLLogging, and cleaned up the names so there are no collisions with Logging.jl. Running simple benchmarks again to make sure nothing changed:

using LinearSolve, Chairmarks
using SciMLLogging
using JET
using Test

n = 4
A = rand(n, n)
b1 = rand(n);
b2 = rand(n);
prob = LinearProblem(A, b1)

@b solve(prob, verbose = false)
368.538 ns (12 allocs: 1.031 KiB)

@b solve(prob, verbose = true )
365.672 ns (12 allocs: 1.031 KiB)

@b solve(prob, verbose = LinearVerbosity()) 
367.880 ns (13 allocs: 1.047 KiB)

@b solve(prob)
361.778 ns (12 allocs: 1.031 KiB)

opt = @report_opt solve(prob, LUFactorization(), verbose = LinearVerbosity())
No errors detected

opt = @report_opt solve(prob, LUFactorization(), verbose = LinearVerbosity(SciMLLogging.None()))
No errors detected

opt = @report_opt solve(prob, LUFactorization(), verbose = false)
No errors detected

cache = init(prob, LUFactorization())

@b solve!(cache) 
103.779 ns (1 allocs: 48 bytes)

A = [1.0 0 0 0
    0 1 0 0
    0 0 1 0
    0 0 0 0]
b = rand(4)
prob = LinearProblem(A, b)

solve(
    prob,
    verbose=LinearVerbosity(default_lu_fallback=WarnLevel()))

@test_logs (:warn,
    "LU factorization failed, falling back to QR factorization. `A` is potentially rank-deficient.") solve(
    prob,
    verbose=LinearVerbosity(default_lu_fallback=WarnLevel()))
    
verb = LinearVerbosity(default_lu_fallback = Silent())

cache = init(prob, verbose = false)

@b solve!(cache)
105.875 ns (1 allocs: 48 bytes)

@jClugstor
Copy link
Member Author

@ChrisRackauckas BLAS logging is in this now. In order to completely test I added the "BLIS Verbosity Integration Tests" testset https://github.com/SciML/LinearSolve.jl/pull/756/files#diff-89192f46443cdf6aec03225b86e08aa1554d15671259bf9cc9957a3e75d96851R323 which doesn't run on CI because blis_jll isn't available, but I ran those tests locally and made sure they pass and give the expected output.

@ChrisRackauckas
Copy link
Member

Just don't load BLIS then.

@jClugstor
Copy link
Member Author

I should just get rid of that testset?

@ChrisRackauckas
Copy link
Member

If BLIS doesn't load then just don't use it. Also, it should not just test BLIS, the least used BLAS. You need to also cover MKL, AppleAccelerate, and OpenBLAS.

@jClugstor
Copy link
Member Author

Ah yeah, I have it check if the extension is loaded and don't run the tests if it isn't.
Ok, I'll add those in as well.

@jClugstor jClugstor mentioned this pull request Sep 28, 2025
Merged
5 tasks
@jClugstor jClugstor changed the title Fixed Verbosity System SciMLLogging Integration Oct 14, 2025
@jClugstor
Copy link
Member Author

@ChrisRackauckas here's some examples for LU, and GMRES from Krylov.jl and KrylovKit.jl

For the LU solver the warning saying that it has to fallback to QR factorization only shows up in the Standard preset or higher.

Krylov.jl only has a binary verbosity toggle, which turns on at the Detailed level or higher, and the messages are only printed and aren't sent to the logs.

KrylovKit has a couple of different verbosity settings, so Standard() turns on their WARN_LEVEL, Detailed() turns on their START_STOP, and All() turns on their EACHITERATION_LEVEL.

using LinearSolve
using SciMLLogging
using Test
using LinearAlgebra
using Logging

# Create a rank-deficient matrix to trigger LU fallback
A = [1.0 0 0 0
    0 1 0 0
    0 0 1 0
    0 0 0 0]
b = rand(4)

# LU Factorization Examples with Verbosity Presets

# None preset - completely silent
prob = LinearProblem(A, b)
@test_logs sol = solve(prob; verbose = None())

# Minimal preset - only critical errors
prob = LinearProblem(A, b)
@test_logs sol = solve(prob; verbose = Minimal())

# Standard preset - warnings and errors (should see LU fallback warning)
prob = LinearProblem(A, b)
@test_logs (:warn, r"LU") sol = solve(prob; verbose = Standard())

# Detailed preset - debugging info
prob = LinearProblem(A, b)
@test_logs (:warn, r"LU") sol = solve(prob; verbose = Detailed())

# All preset - maximum verbosity
prob = LinearProblem(A, b)
@test_logs (:warn, r"LU") sol = solve(prob; verbose = All())

# GMRES (KrylovJL) Examples

# None preset
prob = LinearProblem(A, b)
@test_logs sol = solve(prob, KrylovJL_GMRES(); verbose = None())

# Minimal preset
prob = LinearProblem(A, b)
@test_logs sol = solve(prob, KrylovJL_GMRES(); verbose = Minimal())

# Standard preset
prob = LinearProblem(A, b)
sol = solve(prob, KrylovJL_GMRES(); verbose = Standard())

# Detailed preset 
prob = LinearProblem(A, b)
sol = solve(prob, KrylovJL_GMRES(); verbose = Detailed())

# All preset
prob = LinearProblem(A, b)
sol = solve(prob, KrylovJL_GMRES(); verbose = All())

# GMRES (KrylovKit) Examples

# None preset - completely silent
prob = LinearProblem(A, b)
@test_logs sol = solve(prob, KrylovKitJL_GMRES(); verbose = None())

# Minimal preset - only critical errors
prob = LinearProblem(A, b)
@test_logs sol = solve(prob, KrylovKitJL_GMRES(); verbose = Minimal())

# Standard preset - warnings (KrylovKit CustomLevel(1) = WARN_LEVEL)
prob = LinearProblem(A, b)
@test_logs (:warn, r"GMRES") sol = solve(prob, KrylovKitJL_GMRES(); verbose = Standard())

# Detailed preset - start/stop info (KrylovKit CustomLevel(2) = STARTSTOP_LEVEL)
prob = LinearProblem(A, b)
@test_logs (:info, r"norm") match_mode=:any sol = solve(prob, KrylovKitJL_GMRES(); verbose = Detailed())

# All preset - every iteration (KrylovKit CustomLevel(3) = EACHITERATION_LEVEL)
prob = LinearProblem(A, b)
@test_logs (:info, r"iteration") match_mode=:any sol = solve(prob, KrylovKitJL_GMRES(); verbose = All())

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Reviewers

No reviews

Assignees

No one assigned

Labels

None yet

Projects

None yet

Milestone

No milestone

Development

Successfully merging this pull request may close these issues.

2 participants

@jClugstor @ChrisRackauckas